Closed Bug 1714232 Opened 4 years ago Closed 2 years ago

Intermittent SUMMARY: ThreadSanitizer: thread leak /builds/worker/checkouts/gecko/nsprpub/pr/src/pthreads/ptthread.c:458:14 in _PR_CreateThread

Categories

(Core :: Networking: DNS, defect, P5)

defect

Tracking

()

RESOLVED WORKSFORME

People

(Reporter: intermittent-bug-filer, Unassigned)

References

(Blocks 1 open bug)

Details

(Keywords: intermittent-failure)

Filed by: malexandru [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=341573529&repo=mozilla-central
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/aNV_E3SlR5asouMLDRDvTg/runs/0/artifacts/public/logs/live_backing.log
Reftest URL: https://hg.mozilla.org/mozilla-central/raw-file/tip/layout/tools/reftest/reftest-analyzer.xhtml#logurl=https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/aNV_E3SlR5asouMLDRDvTg/runs/0/artifacts/public/logs/live_backing.log&only_show_unexpected=1


[task 2021-06-02T22:26:31.126Z] 22:26:31     INFO - REFTEST TEST-START | dom/html/reftests/body-frame-margin-remove-other-pres-hint.html == dom/html/reftests/body-frame-margin-remove-other-pres-hint-ref.html
[task 2021-06-02T22:26:31.129Z] 22:26:31     INFO - REFTEST TEST-LOAD | file:///builds/worker/workspace/build/tests/reftest/tests/dom/html/reftests/body-frame-margin-remove-other-pres-hint.html | 48 / 49 (97%)
[task 2021-06-02T22:26:31.560Z] 22:26:31     INFO - REFTEST TEST-LOAD | file:///builds/worker/workspace/build/tests/reftest/tests/dom/html/reftests/body-frame-margin-remove-other-pres-hint-ref.html | 48 / 49 (97%)
[task 2021-06-02T22:26:31.894Z] 22:26:31     INFO - REFTEST TEST-PASS | dom/html/reftests/body-frame-margin-remove-other-pres-hint.html == dom/html/reftests/body-frame-margin-remove-other-pres-hint-ref.html | image comparison, max difference: 0, number of differing pixels: 0
[task 2021-06-02T22:26:31.896Z] 22:26:31     INFO - REFTEST TEST-END | dom/html/reftests/body-frame-margin-remove-other-pres-hint.html == dom/html/reftests/body-frame-margin-remove-other-pres-hint-ref.html
[task 2021-06-02T22:26:31.951Z] 22:26:31     INFO - REFTEST INFO | Slowest test took 2021ms (file:///builds/worker/workspace/build/tests/reftest/tests/dom/html/reftests/bug917595-iframe-1.html)
[task 2021-06-02T22:26:31.954Z] 22:26:31     INFO - REFTEST INFO | Total canvas count = 2
[task 2021-06-02T22:26:33.274Z] 22:26:33     INFO - ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2021-06-02T22:26:33.279Z] 22:26:33     INFO - ###!!! [Parent][MessageChannel] Error: (msgtype=0x950001,name=PTexture::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
[task 2021-06-02T22:26:33.281Z] 22:26:33     INFO - ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2021-06-02T22:26:33.283Z] 22:26:33     INFO - ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2021-06-02T22:26:33.963Z] 22:26:33     INFO - ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2021-06-02T22:26:35.922Z] 22:26:35     INFO - 1622672795921	Marionette	TRACE	Received observer notification xpcom-will-shutdown
[task 2021-06-02T22:26:35.925Z] 22:26:35     INFO - 1622672795922	Marionette	INFO	Stopped listening on port 2828
[task 2021-06-02T22:26:35.926Z] 22:26:35     INFO - 1622672795923	Marionette	DEBUG	Marionette stopped listening
[task 2021-06-02T22:26:44.565Z] 22:26:44     INFO - ==================
[task 2021-06-02T22:26:44.567Z] 22:26:44     INFO - WARNING: ThreadSanitizer: thread leak (pid=3003)
[task 2021-06-02T22:26:44.568Z] 22:26:44     INFO -   Thread T1 'DNS Resolver #1' (tid=3218, finished) created by main thread at:
[task 2021-06-02T22:26:44.570Z] 22:26:44     INFO -     #0 pthread_create /builds/worker/fetches/llvm-project/llvm/projects/compiler-rt/lib/tsan/rtl/tsan_interceptors_posix.cpp:965:3 (firefox+0x577eb)
[task 2021-06-02T22:26:44.570Z] 22:26:44     INFO -     #1 _PR_CreateThread /builds/worker/checkouts/gecko/nsprpub/pr/src/pthreads/ptthread.c:458:14 (libnspr4.so+0x3be33)
[task 2021-06-02T22:26:44.571Z] 22:26:44     INFO -     #2 PR_CreateThread /builds/worker/checkouts/gecko/nsprpub/pr/src/pthreads/ptthread.c:533:12 (libnspr4.so+0x30915)
[task 2021-06-02T22:26:44.572Z] 22:26:44     INFO -     #3 nsThread::Init(nsTSubstring<char> const&) /builds/worker/checkouts/gecko/xpcom/threads/nsThread.cpp:613:18 (libxul.so+0xbdff52)
[task 2021-06-02T22:26:44.573Z] 22:26:44     INFO -     #4 nsThreadManager::NewNamedThread(nsTSubstring<char> const&, unsigned int, nsIThread**) /builds/worker/checkouts/gecko/xpcom/threads/nsThreadManager.cpp:574:12 (libxul.so+0xbe800a)
[task 2021-06-02T22:26:44.573Z] 22:26:44     INFO -     #5 NS_NewNamedThread(nsTSubstring<char> const&, nsIThread**, already_AddRefed<nsIRunnable>, unsigned int) /builds/worker/checkouts/gecko/xpcom/threads/nsThreadUtils.cpp:169:57 (libxul.so+0xbefe34)
[task 2021-06-02T22:26:44.574Z] 22:26:44     INFO -     #6 NS_NewNamedThread /builds/worker/checkouts/gecko/xpcom/threads/nsThreadUtils.cpp:160:10 (libxul.so+0xbeadac)
[task 2021-06-02T22:26:44.575Z] 22:26:44     INFO -     #7 nsThreadPool::PutEvent(already_AddRefed<nsIRunnable>, unsigned int) /builds/worker/checkouts/gecko/xpcom/threads/nsThreadPool.cpp:118:17 (libxul.so+0xbeadac)
[task 2021-06-02T22:26:44.576Z] 22:26:44     INFO -     #8 nsThreadPool::Dispatch(already_AddRefed<nsIRunnable>, unsigned int) /builds/worker/checkouts/gecko/xpcom/threads/nsThreadPool.cpp:354:5 (libxul.so+0xbec30f)
[task 2021-06-02T22:26:44.576Z] 22:26:44     INFO -     #9 non-virtual thunk to nsThreadPool::Dispatch(already_AddRefed<nsIRunnable>, unsigned int) /builds/worker/checkouts/gecko/xpcom/threads/nsThreadPool.cpp (libxul.so+0xbec838)
[task 2021-06-02T22:26:44.577Z] 22:26:44     INFO -     #10 Dispatch /builds/worker/workspace/obj-build/dist/include/nsIEventTarget.h:41:14 (libxul.so+0xe0cf43)
[task 2021-06-02T22:26:44.578Z] 22:26:44     INFO -     #11 nsHostResolver::ConditionallyCreateThread(nsHostRecord*) /builds/worker/checkouts/gecko/netwerk/dns/nsHostResolver.cpp:1329:27 (libxul.so+0xe0cf43)
[task 2021-06-02T22:26:44.579Z] 22:26:44     INFO -     #12 nsHostResolver::NativeLookup(nsHostRecord*) /builds/worker/checkouts/gecko/netwerk/dns/nsHostResolver.cpp:1500:17 (libxul.so+0xe0ea77)
[task 2021-06-02T22:26:44.579Z] 22:26:44     INFO -     #13 nsHostResolver::NameLookup(nsHostRecord*) /builds/worker/checkouts/gecko/netwerk/dns/nsHostResolver.cpp:1667:10 (libxul.so+0xe0cb43)
[task 2021-06-02T22:26:44.580Z] 22:26:44     INFO -     #14 nsHostResolver::ResolveHost(nsTSubstring<char> const&, nsTSubstring<char> const&, unsigned short, mozilla::OriginAttributes const&, unsigned short, unsigned short, nsResolveHostCallback*) /builds/worker/checkouts/gecko/netwerk/dns/nsHostResolver.cpp:1219:14 (libxul.so+0xe0b701)
[task 2021-06-02T22:26:44.582Z] 22:26:44     INFO -     #15 nsDNSService::AsyncResolveInternal(nsTSubstring<char> const&, unsigned short, unsigned int, nsIDNSResolverInfo*, nsIDNSListener*, nsIEventTarget*, mozilla::OriginAttributes const&, nsICancelable**) /builds/worker/checkouts/gecko/netwerk/dns/nsDNSService2.cpp:1035:13 (libxul.so+0xe4bf51)
[task 2021-06-02T22:26:44.583Z] 22:26:44     INFO -     #16 nsDNSService::AsyncResolveNative(nsTSubstring<char> const&, nsIDNSService::ResolveType, unsigned int, nsIDNSResolverInfo*, nsIDNSListener*, nsIEventTarget*, mozilla::OriginAttributes const&, nsICancelable**) /builds/worker/checkouts/gecko/netwerk/dns/nsDNSService2.cpp:1106:10 (libxul.so+0xe4c903)
[task 2021-06-02T22:26:44.588Z] 22:26:44     INFO -     #17 mozilla::dom::HTMLDNSPrefetch::Prefetch(nsTSubstring<char16_t> const&, bool, mozilla::OriginAttributes const&, unsigned int) /builds/worker/checkouts/gecko/dom/html/HTMLDNSPrefetch.cpp:243:30 (libxul.so+0x3ac09d3)
[task 2021-06-02T22:26:44.588Z] 22:26:44     INFO -     #18 mozilla::net::NeckoParent::RecvHTMLDNSPrefetch(nsTString<char16_t> const&, bool const&, mozilla::OriginAttributes const&, unsigned int const&) /builds/worker/checkouts/gecko/netwerk/ipc/NeckoParent.cpp:545:3 (libxul.so+0x1345f63)
[task 2021-06-02T22:26:44.588Z] 22:26:44     INFO -     #19 mozilla::net::PNeckoParent::OnMessageReceived(IPC::Message const&) /builds/worker/workspace/obj-build/ipc/ipdl/PNeckoParent.cpp:2346:55 (libxul.so+0x179504e)
[task 2021-06-02T22:26:44.594Z] 22:26:44     INFO -     #20 mozilla::dom::PContentParent::OnMessageReceived(IPC::Message const&) /builds/worker/workspace/obj-build/ipc/ipdl/PContentParent.cpp:6677:32 (libxul.so+0x1607191)
[task 2021-06-02T22:26:44.594Z] 22:26:44     INFO -     #21 mozilla::ipc::MessageChannel::DispatchAsyncMessage(mozilla::ipc::ActorLifecycleProxy*, IPC::Message const&) /builds/worker/checkouts/gecko/ipc/glue/MessageChannel.cpp:2155:25 (libxul.so+0x14afa51)
[task 2021-06-02T22:26:44.595Z] 22:26:44     INFO -     #22 mozilla::ipc::MessageChannel::DispatchMessage(IPC::Message&&) /builds/worker/checkouts/gecko/ipc/glue/MessageChannel.cpp:2079:9 (libxul.so+0x14addd5)
[task 2021-06-02T22:26:44.595Z] 22:26:44     INFO -     #23 mozilla::ipc::MessageChannel::RunMessage(mozilla::ipc::MessageChannel::MessageTask&) /builds/worker/checkouts/gecko/ipc/glue/MessageChannel.cpp:1924:3 (libxul.so+0x14ae9da)
[task 2021-06-02T22:26:44.596Z] 22:26:44     INFO -     #24 mozilla::ipc::MessageChannel::MessageTask::Run() /builds/worker/checkouts/gecko/ipc/glue/MessageChannel.cpp:1955:13 (libxul.so+0x14aefe1)
[task 2021-06-02T22:26:44.596Z] 22:26:44     INFO -     #25 mozilla::RunnableTask::Run() /builds/worker/checkouts/gecko/xpcom/threads/TaskController.cpp:482:16 (libxul.so+0xbf45b7)
[task 2021-06-02T22:26:44.597Z] 22:26:44     INFO -     #26 mozilla::TaskController::DoExecuteNextTaskOnlyMainThreadInternal(mozilla::detail::BaseAutoLock<mozilla::Mutex&> const&) /builds/worker/checkouts/gecko/xpcom/threads/TaskController.cpp:785:26 (libxul.so+0xbd167a)
[task 2021-06-02T22:26:44.597Z] 22:26:44     INFO -     #27 mozilla::TaskController::ExecuteNextTaskOnlyMainThreadInternal(mozilla::detail::BaseAutoLock<mozilla::Mutex&> const&) /builds/worker/checkouts/gecko/xpcom/threads/TaskController.cpp:621:15 (libxul.so+0xbcfcd6)
[task 2021-06-02T22:26:44.598Z] 22:26:44     INFO -     #28 mozilla::TaskController::ProcessPendingMTTask(bool) /builds/worker/checkouts/gecko/xpcom/threads/TaskController.cpp:405:36 (libxul.so+0xbcffa4)
[task 2021-06-02T22:26:44.599Z] 22:26:44     INFO -     #29 operator() /builds/worker/checkouts/gecko/xpcom/threads/TaskController.cpp:138:37 (libxul.so+0xbf84a7)
[task 2021-06-02T22:26:44.599Z] 22:26:44     INFO -     #30 mozilla::detail::RunnableFunction<mozilla::TaskController::InitializeInternal()::$_0>::Run() /builds/worker/checkouts/gecko/xpcom/threads/nsThreadUtils.h:534:5 (libxul.so+0xbf84a7)
[task 2021-06-02T22:26:44.600Z] 22:26:44     INFO -     #31 nsThread::ProcessNextEvent(bool, bool*) /builds/worker/checkouts/gecko/xpcom/threads/nsThread.cpp:1159:16 (libxul.so+0xbe2260)
[task 2021-06-02T22:26:44.600Z] 22:26:44     INFO -     #32 NS_ProcessNextEvent(nsIThread*, bool) /builds/worker/checkouts/gecko/xpcom/threads/nsThreadUtils.cpp:548:10 (libxul.so+0xbe9182)
[task 2021-06-02T22:26:44.601Z] 22:26:44     INFO -     #33 mozilla::ipc::MessagePump::Run(base::MessagePump::Delegate*) /builds/worker/checkouts/gecko/ipc/glue/MessagePump.cpp:85:21 (libxul.so+0x14b32bd)
[task 2021-06-02T22:26:44.601Z] 22:26:44     INFO -     #34 RunInternal /builds/worker/checkouts/gecko/ipc/chromium/src/base/message_loop.cc:335:10 (libxul.so+0x143d3bc)
[task 2021-06-02T22:26:44.601Z] 22:26:44     INFO -     #35 RunHandler /builds/worker/checkouts/gecko/ipc/chromium/src/base/message_loop.cc:328:3 (libxul.so+0x143d3bc)
[task 2021-06-02T22:26:44.602Z] 22:26:44     INFO -     #36 MessageLoop::Run() /builds/worker/checkouts/gecko/ipc/chromium/src/base/message_loop.cc:310:3 (libxul.so+0x143d3bc)
[task 2021-06-02T22:26:44.602Z] 22:26:44     INFO -     #37 nsBaseAppShell::Run() /builds/worker/checkouts/gecko/widget/nsBaseAppShell.cpp:137:27 (libxul.so+0x4b8f3d6)
[task 2021-06-02T22:26:44.603Z] 22:26:44     INFO -     #38 nsAppStartup::Run() /builds/worker/checkouts/gecko/toolkit/components/startup/nsAppStartup.cpp:273:30 (libxul.so+0x6917ec8)
[task 2021-06-02T22:26:44.603Z] 22:26:44     INFO -     #39 XREMain::XRE_mainRun() /builds/worker/checkouts/gecko/toolkit/xre/nsAppRunner.cpp:5244:22 (libxul.so+0x6a3330f)
[task 2021-06-02T22:26:44.604Z] 22:26:44     INFO -     #40 XREMain::XRE_main(int, char**, mozilla::BootstrapConfig const&) /builds/worker/checkouts/gecko/toolkit/xre/nsAppRunner.cpp:5442:8 (libxul.so+0x6a34057)
[task 2021-06-02T22:26:44.605Z] 22:26:44     INFO -     #41 XRE_main(int, char**, mozilla::BootstrapConfig const&) /builds/worker/checkouts/gecko/toolkit/xre/nsAppRunner.cpp:5501:21 (libxul.so+0x6a345f4)
[task 2021-06-02T22:26:44.605Z] 22:26:44     INFO -     #42 mozilla::BootstrapImpl::XRE_main(int, char**, mozilla::BootstrapConfig const&) /builds/worker/checkouts/gecko/toolkit/xre/Bootstrap.cpp:45:12 (libxul.so+0x6a3ebb2)
[task 2021-06-02T22:26:44.606Z] 22:26:44     INFO -     #43 do_main /builds/worker/checkouts/gecko/browser/app/nsBrowserApp.cpp:224:22 (firefox+0xca6e0)
[task 2021-06-02T22:26:44.606Z] 22:26:44     INFO -     #44 main /builds/worker/checkouts/gecko/browser/app/nsBrowserApp.cpp:351:16 (firefox+0xca6e0)
[task 2021-06-02T22:26:44.607Z] 22:26:44     INFO - SUMMARY: ThreadSanitizer: thread leak /builds/worker/checkouts/gecko/nsprpub/pr/src/pthreads/ptthread.c:458:14 in _PR_CreateThread
[task 2021-06-02T22:26:44.607Z] 22:26:44     INFO - ==================
[task 2021-06-02T22:26:44.715Z] 22:26:44    ERROR - TEST-UNEXPECTED-FAIL | Last test finished | application terminated with exit code -6
[task 2021-06-02T22:26:44.730Z] 22:26:44     INFO - REFTEST INFO | Process mode: e10s
[task 2021-06-02T22:26:44.732Z] 22:26:44  WARNING - leakcheck | refcount logging is off, so leaks can't be detected!
[task 2021-06-02T22:26:44.732Z] 22:26:44     INFO - REFTEST INFO | Running tests in file:///builds/worker/workspace/build/tests/reftest/tests/layout/reftests/forms/input/range/reftest.list
[task 2021-06-02T22:26:44.763Z] 22:26:44     INFO - REFTEST INFO | INFO | runtests.py | TSan using symbolizer at /builds/worker/workspace/build/application/firefox/llvm-symbolizer
[task 2021-06-02T22:26:44.763Z] 22:26:44     INFO - REFTEST INFO | Running with e10s: True
[task 2021-06-02T22:26:44.763Z] 22:26:44     INFO - REFTEST INFO | Running with fission: False
[task 2021-06-02T22:26:44.763Z] 22:26:44     INFO - REFTEST INFO | Application command: /builds/worker/workspace/build/application/firefox/firefox -marionette -profile /tmp/tmpwcnif1s8.mozrunner
[task 2021-06-02T22:26:49.532Z] 22:26:49     INFO - 1622672809530	Marionette	INFO	Marionette enabled
[task 2021-06-02T22:26:50.303Z] 22:26:50     INFO - 1622672810302	Marionette	TRACE	Received observer notification toplevel-window-ready
[task 2021-06-02T22:26:59.231Z] 22:26:59     INFO - console.warn: SearchSettings: "get: No settings file exists, new profile?" (new NotFoundError("Could not open the file at /tmp/tmpwcnif1s8.mozrunner/search.json.mozlz4", (void 0)))
[task 2021-06-02T22:27:07.654Z] 22:27:07     INFO - 1622672827653	Marionette	TRACE	Received observer notification marionette-startup-requested
[task 2021-06-02T22:27:07.656Z] 22:27:07     INFO - 1622672827655	Marionette	TRACE	Waiting until startup recorder finished recording startup scripts...
[task 2021-06-02T22:27:07.780Z] 22:27:07     INFO - 1622672827779	Marionette	TRACE	All scripts recorded.
[task 2021-06-02T22:27:07.794Z] 22:27:07     INFO - 1622672827793	Marionette	INFO	Listening on port 2828
[task 2021-06-02T22:27:07.796Z] 22:27:07     INFO - 1622672827795	Marionette	DEBUG	Marionette is listening
[task 2021-06-02T22:27:08.202Z] 22:27:08     INFO - 1622672828201	Marionette	DEBUG	Accepted connection 0 from 127.0.0.1:53246
[task 2021-06-02T22:27:08.229Z] 22:27:08     INFO - 1622672828228	Marionette	DEBUG	Accepted connection 1 from 127.0.0.1:53248
[task 2021-06-02T22:27:08.232Z] 22:27:08     INFO - 1622672828231	Marionette	DEBUG	Closed connection 0
[task 2021-06-02T22:27:08.346Z] 22:27:08     INFO - 1622672828345	Marionette	DEBUG	1 -> [0,1,"WebDriver:NewSession",{"strictFileInteractability":true}]
[task 2021-06-02T22:27:08.526Z] 22:27:08     INFO - 1622672828524	Marionette	DEBUG	1 <- [1,1,null,{"sessionId":"4d487e38-0f7c-442f-8427-53ce1ac0e543","capabilities":{"browserName":"firefox","browserVersion":"91.0a ... .mozrunner","moz:shutdownTimeout":360000,"moz:useNonSpecCompliantPointerOrigin":false,"moz:webdriverClick":true,"proxy":{}}}]
[task 2021-06-02T22:27:08.555Z] 22:27:08     INFO - 1622672828554	Marionette	DEBUG	1 -> [0,2,"Addon:Install",{"path":"/builds/worker/workspace/build/tests/reftest/reftest","temporary":true}]
[task 2021-06-02T22:27:09.075Z] 22:27:09     INFO - 1622672829074	Marionette	TRACE	Received observer notification toplevel-window-ready
[task 2021-06-02T22:27:09.086Z] 22:27:09     INFO - 1622672829085	Marionette	DEBUG	1 <- [1,2,null,{"value":"reftest@mozilla.org"}]
[task 2021-06-02T22:27:09.141Z] 22:27:09     INFO - 1622672829140	Marionette	DEBUG	1 -> [0,3,"WebDriver:DeleteSession",{}]
[task 2021-06-02T22:27:09.167Z] 22:27:09     INFO - 1622672829165	Marionette	DEBUG	1 <- [1,3,null,{"value":null}]
[task 2021-06-02T22:27:09.177Z] 22:27:09     INFO - 1622672829176	Marionette	DEBUG	Closed connection 1
[task 2021-06-02T22:27:09.569Z] 22:27:09     INFO - ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2021-06-02T22:27:09.572Z] 22:27:09     INFO - ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2021-06-02T22:27:10.470Z] 22:27:10     INFO - REFTEST TEST-START | layout/reftests/forms/input/range/not-other-type-unthemed-1.html != layout/reftests/forms/input/range/not-other-type-unthemed-1a-notref.html
Group: core-security

This looks like a resource leak, but not exploitable.

Group: core-security
Component: NSPR → Networking: DNS
Product: NSPR → Core
Version: other → unspecified
Blocks: tsan

This is really rare - the problem was that a DNS thread leaked.
We'll reopen if it happens again.

Status: NEW → RESOLVED
Closed: 2 years ago
Resolution: --- → WORKSFORME
You need to log in before you can comment on or make changes to this bug.